"""

.. module:: a2pspear_service

*Description*:

This module includes all functionality for scraping data from SPEAR HTML.

*Constants*:

.. seealso:: class :class:`spear.a2p_service.A2PService`
"""

# Imports
#
import logging
import time
import httplib
from HTMLParser import HTMLParser, HTMLParseError
from datetime import datetime, date
import re
import base64

from runtime.service import Service
from datastore.database import DataStore, NotFoundException
from spear.http import HTTP
from datastore.resource import Resource
from datastore.uri import Uri
from runtime.nodelogger import NodeLogger
from datastore.spaces import Spaces

# Constants
#

# Classes
#

class A2PSpearService(Service):
    """
    This class is responsible for creating and sending HTTP requests to Spear
    and extracting the required data from the HTML responses. 
    
    **Constants**:
    
    .. data:: STATE_LOGGEDOUT
    
        The state of the service when we are currently NOT logged-in to Spear.
    
    .. data:: STATE_LOGGEDIN
    
        The state of the service when we are currently logged-in to Spear.
    
    :param spaces: runtime.spaces.Spaces - Reference to spaces
    :param ds: datastore.database.DataStore
    :param service_uri: String - the uri for this service. 
    """
    
    # Class constants
    #
    STATE_LOGGEDOUT = 0
    STATE_LOGGEDIN = 1
    def __init__(self, spaces, ds, service_uri):
        # <purpose>
        #
        
        Service.__init__(self, spaces=spaces, datastore=ds, uri=service_uri, node_start=False)
        
        self.logger = NodeLogger.getLogger('eplanning.spear.a2pspear_service.A2PSpearService')
        self.logger.log(logging.DEBUG, "spaces (%s), ds (%s), service_uri (%s)" % (spaces, ds, service_uri))
        
        # Must use a single instance of HTTP for all requests so we use a single 
        # cookie jar.
        #
        self.http = HTTP()
        
        self.state = A2PSpearService.STATE_LOGGEDOUT
        
        # Load all request and instruction definitions into spaces.
        #
        request_rs_list = self.get_spear_requests_from_ds()
        for rs in request_rs_list:
            self.spaces.put(rs.get_metadata(Uri('spear:request/uri')), rs)

        self.user_role_council = ""
        self.user_role_administrator = ""
        
        self.last_spear_connection_status = None
        
    def cb_start(self, uri, action, rs):
        """
        This function is called when the service starts. 
        
        :param uri: Uri - The service Uri.
        :param action: String - spaces action, probably 'put'.
        :param rs: Resource - This service's definition Resource.
        """

        # Load Spear static
        #
        self.statics = rs.options.statics
        
        self.logger.log(logging.DEBUG, "uri (%s), action (%s)" % (uri, action))
        
        self.spaces.set_process(self.service_def.api.a2pspearrequest.uri, self.cb_process_a2pspear_request)
        self.spaces.set_process(self.service_def.api.a2pspearstatus.uri, self.cb_process_a2pspear_status)
    
    def cb_stop(self, uri, action, rs):
        """
        This function will stop any listeners still running.
        
        :param uri: Uri - The service Uri.
        :param action: String - spaces action, probably 'put'.
        :param rs: Resource - This service's definition Resource.
        """
        
        self.logger.log(logging.DEBUG, "uri (%s), action (%s), rs (%s)" % (uri, action, rs.pretty_print()))
    
    def cb_process_a2pspear_status(self, uri, action, rs):
        """
        This function returns a Resource containing the status of the connection to SPEAR.
        """
        if action == Spaces.ACTION_GET:
            rs = Resource(type="term:eplanning/spear/a2pspear_service/a2pspearstatus")
            if self.last_spear_connection_status == None:
                rs.date = None
                rs.connection_up = None
            else:
                rs.date = self.last_spear_connection_status[0]
                rs.connection_up = self.last_spear_connection_status[1]
            return rs
    
    def cb_process_a2pspear_request(self, uri, action, rs):
        """
        This function is called from Spaces to process user requests. Here we 
        find the appropriate list of Spear instructions and add to the immediate 
        queue.
        
        This function controls the state of the Spear connection. If we are not 
        yet logged-in to Spear then we login before processing the request.
        
        :param uri: Uri - The service Uri.
        :param action: String - spaces action, probably 'put'.
        :param rs: Resource - This service's definition Resource.
        """
        
        self.logger.log(logging.DEBUG, "uri (%s), action (%s), rs (%s)" % (uri, action, rs))
        
        if (action is not None) and \
           ((action == 'exists') or \
            (action == 'remove')):
            return False
        
        self.spaces.remove(uri)
        
        self.logger.log(NodeLogger.TRACE, "uri (%s), action (%s), rs (%s)" % (uri, action, rs.pretty_print()))
        
        # find the list of Spear instructions matching the user's request.
        #
        a2pspear_request_uri = rs.get_var('a2pspear:request/uri')
        if (a2pspear_request_uri is not None):
            # Requests to A2P are URIs of the form "req:....".
            #
            request_rs = self.spaces.get(Uri(a2pspear_request_uri))
            if (request_rs is not None):
                self.logger.log(NodeLogger.TRACE, "found Spear request in Spaces (%s) " % request_rs.pretty_print())
                
                # login to Spear if not already. Don't keep knocking on the door 
                # if it keeps failing otherwise Spear will de-activate the login
                # and we'll never get in. On failure, back-off for a minute and 
                # try again.
                #
                
                # Get the UUID from the request that we will respond with.
                #
                uuid_str = rs.get_var(Uri('a2pspear:request/uuid'))
                response_uri = Uri('internal:base/services/a2pspear_service/a2pspearresponse') + uuid_str
                
                # TODO: Call to A2PSpear come from an async() A2P. Therefore the following 
                #       sleep() will not affect all services, just the async(). So, should we:
                #       - sleep() on login failure?
                #       - put() request back to spaces and try login on next request?
                #         - won't the put() just generate another callback?
                # TODO: Post error (somewhere) if log-in fails.
                #
                
                if (self.state == A2PSpearService.STATE_LOGGEDOUT):
                    login_request_rs = self.spaces.get(Uri('spear:request/login'))
                    output_rs = self.do_process_request(login_request_rs, self.spaces)
                    if not output_rs.success:
                        self.logger.log(logging.ERROR, "Login failure to Spear.")
                        
                        # send error to user.
                        #
                        output_rs.set_var('a2pspear:request/uri', a2pspear_request_uri)
                        output_rs.set_var('a2pspear:request/uuid', uuid_str)
                        self.spaces.put(response_uri, output_rs)
                        return response_uri
                    else:
                        # Save the user roles as these are needed to swap to and from administrator
                        # to retrieve user and RA lists.
                        #
                        self.user_role_council = output_rs.user_role_council
                        self.user_role_administrator = output_rs.user_role_administrator
                        
                        self.logger.log(NodeLogger.TRACE, "user_role_council (%s), user_role_council (%s)" % (self.user_role_council, self.user_role_administrator))                        
                        self.state = A2PSpearService.STATE_LOGGEDIN                        
                
                # copy request arguments from user request.
                #
                if (rs.has_var("arguments_dict")):
                    request_rs.set_var("arguments_dict", rs.get_var("arguments_dict"))
                    request_rs.arguments_dict['user_role_council'] = self.user_role_council
                    request_rs.arguments_dict['user_role_administrator'] = self.user_role_administrator
                output_rs = self.do_process_request(request_rs, self.spaces)
                output_rs.set_var('a2pspear:request/uri', a2pspear_request_uri)
                output_rs.set_var('a2pspear:request/uuid', uuid_str)
                self.spaces.put(response_uri, output_rs)
                return response_uri

            else:
                self.logger.log(logging.INFO, "No Spear request found in datastore for uri (%s)" % a2pspear_request_uri)
        else:
            self.logger.log(logging.WARN, "Request does not contain a Spear request")
        
        return None
    
    def do_process_request(self, request_rs, spaces):
        """
        This function loops through the request's instruction list, processing
        one instruction at a time against Spear.
        
        Each user request contains the following items that are made available to
        the python code sections of each instruction and used during key/value
        substitution of request and response URLs.
            
        - 'arguments_dict' - a dictionary of user request arguments. 
            
        Each request instruction contains the following items that are made 
        available to the python code sections of each instruction.
            
        - 'request_const_dict' - a dictionary made available to "request_python_code".
            
        - 'response_const_dict' - a dictionary made available to "response_python_code"
          and HTML parsing. Keys in this dictionary are searched for in the HTML
          to determine the values for the keys. Values are saved into
          the dictionary and become available to 'response_python_code'.
            
        - 'error_const_dict' - a dictionary made available to "error_python_code" and
          HTML parsing. 
            
        The following items are made available to an instruction's python code:
            
        - 'post_data' - a dictionary that can be used to send key/value pairs in POST 
          requests.
            
        - 'inter_instruction_dict' - a dictionary that can be populated by one 
          instruction and used by the next. It is made available to all instructions 
          within a request, but not across requests.
        
        - 'is_ok' - a boolean to indicate if the instruction succeeded or not. True = 
          success.
        
        - 'error_string' - a string to be set on error.
          
        Any variable substitutions required for the instruction's "url" 
        are taken from:
            
        - the user's 'arguments_dict', if the variable exists, otherwise
        - the instruction's 'request_params' dictionary, otherwise
        - the 'inter_instruction_dict'.
        
        :param request_rs: Resource - An Action Resource
        :rtype: Resource - Data from Spear
        """

        log_rs = Resource(type="term:base/services/logger/logs")
        log_rs.log_entries = [("Issuing Request: %s" % request_rs.get_metadata(Uri('spear:request/uri')), None)]
        spaces.put(Uri("internal:base/services/logger/logs/"), log_rs)
        self.logger.log(NodeLogger.TRACE, "do_process_request(): request_rs (%s)" % (request_rs))
        
        output_rs = Resource(type='term:eplanning/spear/a2pspear_service/a2pspearresponse')
        
        arguments_dict = {}
        if (request_rs.has_var("arguments_dict")):
            arguments_dict = request_rs.get_var("arguments_dict")
        
        # This dictionary is made available to the python code of all instructions.
        # It can be used to pass data from one instruction to another and populate
        # URLs.
        #
        inter_instruction_dict = {}
        
        error_string = None
        for instruction_dict in request_rs.get_var("instructions_dict_list"):
            error_string = self.do_process_instruction(instruction_dict, inter_instruction_dict, arguments_dict, request_rs, output_rs)
            if error_string:
                log_rs.log_entries = [("Instruction %s Failed. Error message: %s" % (instruction_dict['metadata_instruction_uri'], error_string), None)]
                spaces.put(Uri("internal:base/services/logger/logs/"), log_rs)
                break

        
        # set any error message.
        #
        output_rs.set_var("error", error_string)
        output_rs.set_var("success", (False if error_string else True))
        
        return output_rs
    
    def do_process_instruction(self, instruction_dict, inter_instruction_dict, arguments_dict, request_rs, output_rs):
        self.logger.log(NodeLogger.TRACE, "instruction_dict (%s)" % instruction_dict)
        
        request_dict = instruction_dict["request"]
        response_dict = instruction_dict["response"]
        
        request_const_dict = instruction_dict["request_const_dict"]
        response_const_dict = instruction_dict["response_const_dict"]
        error_const_dict = instruction_dict["error_const_dict"]
        
        post_data = {}
        request_params = request_dict["request_params"]
        is_ok = True
        
        request_python_code = instruction_dict["request_python_code"]
        if (request_python_code is not None):
            self.logger.log(NodeLogger.TRACE, "processing request_python_code (%s)" % request_python_code.strip())
            exec request_python_code.strip()
        
        # Note: I tried using 'urlparse.urlunparse()' and 'urlparse.urlunsplit()'
        #       but they both resulted in a double slash between the hostname
        #       and the path when 'request_dict' requires a full path to
        #       be substituted.
        #

        self.logger.log(NodeLogger.TRACE, "inter_instruction_dict (%s)." % inter_instruction_dict)
                
        request_url = self.statics.protocol + '://' + self.statics.hostname + request_dict["url"]["path"]
        if (len(request_dict["url"]["query"]) > 0):
            request_url += '?' + request_dict["url"]["query"]
        if (len(request_dict["url"]["fragment"]) > 0):
            request_url += '#' + request_dict["url"]["fragment"]

        self.logger.log(NodeLogger.TRACE, "===== 1 request_url (%s)." % request_url)
        
        # perform variable substitution into 'request_url'
        #
        request_url = self.do_url_argument_replacement(request_url, arguments_dict)
        request_url = self.do_url_argument_replacement(request_url, request_params)
        request_url = self.do_url_argument_replacement(request_url, inter_instruction_dict)
                
        expected_response_urls = []
        for response_url in response_dict["urls"]:
            expected_response_url = self.statics.protocol + '://' + self.statics.hostname + response_url["path"]
            if (len(response_url["query"]) > 0):
                expected_response_url += '?' + response_url["query"]
            if (len(response_url["fragment"]) > 0):
                expected_response_url += '#' + response_url["fragment"]
            self.logger.log(NodeLogger.TRACE, "===== 1 response_url (%s)." % response_url)
        
            # perform variable substitution into 'response_url'.
            #
            expected_response_url = self.do_url_argument_replacement(expected_response_url, arguments_dict)
            expected_response_url = self.do_url_argument_replacement(expected_response_url, request_params)
            expected_response_url = self.do_url_argument_replacement(expected_response_url, inter_instruction_dict)
            expected_response_urls.append(expected_response_url)  
                
        self.logger.log(NodeLogger.TRACE, "requesting url (%s)." % request_url)
        self.logger.log(NodeLogger.TRACE, "expected response_urls (%s)." % expected_response_urls)
        
        # make the HTTP request. 
        #
        (code, real_response_url, response) = self.http.issue_request(request_url, post_data)
        
        self.update_spear_connection_status(code)
        
        if (code < 0):
            # IO error in communicating with Spear.
            #
            error_string = "IO error communicating with Spear. Abandoning instructions for request (%s)." % request_rs.get_metadata(Uri("spear:request/uri"))
            self.logger.log(logging.ERROR, error_string)
            self.logger.log(logging.ERROR, "response (%s)." % (response))
            return error_string
        
        elif (code != httplib.OK):
            # Error from Spear. Stop processing instruction list.
            #
            error_string = "HTTP return code (%s) from Spear not OK. Abandoning instructions for request (%s)." % (code, request_rs.get_metadata(Uri("spear:request/uri")))
            self.logger.log(logging.ERROR, error_string)
            self.logger.log(logging.ERROR, "response (%s)." % (response))
            return error_string
        
        # check the response's URL is the same as the expected URL (from instruction)
        #
        elif (not real_response_url in expected_response_urls):
            error_string = "HTTP response URL (%s) from Spear different to that expected urls (%s). Abandoning instructions for request (%s)." % (real_response_url, expected_response_urls, request_rs.get_metadata(Uri("spear:request/uri")))
            self.logger.log(logging.ERROR, error_string)
            return error_string
        
        # should we process the response HTML/PDF?
        #
        elif (response_dict["ignore_output"] is False):
            self.logger.log(NodeLogger.TRACE, "processing response (%s)" % (self.filter_string_data(response)))
            
            error_python_code = instruction_dict["error_python_code"]
            if (error_python_code is not None):
                self.logger.log(NodeLogger.TRACE, "processing error_python_code (%s)" % error_python_code.strip())
                error_python_code = error_python_code.strip()
            response_python_code = instruction_dict["response_python_code"]
            if (response_python_code is not None):
                self.logger.log(NodeLogger.TRACE, "processing response_python_code (%s)" % response_python_code.strip())
                response_python_code = response_python_code.strip()
            
            if (response_dict["output_format"] == "html"):
                parse_tuple_list = []
                html_tag_list = []
                
                # strip out guts of <img /> tags to remove bad tag that kills HTMLParser.
                # 
#                    response = re.sub(r'<img.*>', r'<img/>', response)
#                    self.logger.log(logging.DEBUG, "@@@@@@@@@@@@@@@@@@@@@@@@@ response w/o img tags (%s)" % response)
                
                # Parse returned HTML.
                #
                try:
                    self.parser = SpearHTMLParser(html_tag_list)
                    self.parser.feed(response)
                    self.parser.close()
                    
                    self.logger.log(NodeLogger.TRACE, "html_tag_list (%s)" % html_tag_list)
                
                    parse_tuple_list = self.process_tags(html_tag_list, response_const_dict, error_const_dict)
                    
                    self.logger.log(NodeLogger.TRACE, "parse_tuple_list (%s)" % parse_tuple_list)
                    
                    # HTTP status code doesn't tell us everything about the success 
                    # or not of the request. For example, if login fails Spear will
                    # re-display the login page with an error message; however the 
                    # status code is 200 - OK. So we must perform the instruction's
                    # error python code BEFORE the response python code so we know
                    # what happened.
                    #
                    
                    error_python_code = error_python_code.strip()
                    if (len(error_python_code) > 0):
                        exec error_python_code
                    
                    if (is_ok is True):
                        # All OK. Parse page for any data we require.
                        #
                        response_python_code = response_python_code.strip()
                        if (len(response_python_code) > 0):
                            exec response_python_code
                    else:
                        error_string = "Error detected in Spear response. Abandoning instructions for request (%s)." % request_rs.get_metadata("spear:request/uri")
                        self.logger.log(logging.ERROR, error_string)
                        return error_string
                except HTMLParseError as e:
                    error_string = "HTML Parsing Error (%s) for instruction (%s)" % (e, instruction_dict['metadata_instruction_uri'])
                    self.logger.log(logging.ERROR, error_string)
                    return error_string
#                except Exception as e:
#                    error_string = "HTML Parsing Error (%s)" % e
#                    self.logger.log(logging.ERROR, error_string)
#                    return error_string

            elif (response_dict["output_format"] == "pdf"):
                # We cannot parse from a PDF so just save it straight to a Resource
                # in base64.
                #
                parse_tuple_list = []
                parse_tuple_list.append(("pdf", [base64.standard_b64encode(response)]))
                
                response_python_code = response_python_code.strip()
                if (len(response_python_code) > 0):
                    exec response_python_code
            
            elif (response_dict["output_format"] == "xml"):
                # Save the response straight into the Resource and let the user
                # do something with it.
                #
                parse_tuple_list = []
                parse_tuple_list.append(("xml", [response]))
                
                response_python_code = response_python_code.strip()
                if (len(response_python_code) > 0):
                    exec response_python_code
            
        else:
            self.logger.log(NodeLogger.TRACE, "Ignoring response")        
        self.logger.log(NodeLogger.TRACE, "HTTP return code (%s)" % code)
    
    def process_tags(self, html_tag_list, response_const_dict, error_const_dict):
        """
        This function processes the argument 'html_tag_list' - a list of HTML 
        tags, looking for Spear ids as configured into the arguments
        'response_const_dict' and 'error_const_dict'. When a tag is found the
        tag's instructions are used to determine the location of the data. The
        tag name and the data are then appended (as a tuple) to a list. The
        resultant list of tuples is returned.
        
        :param html_tag_list: List - list of HTML tags, attributes and data.
        :param response_const_dict: Dictionary - configured dictionary of Spear
            ids, with parsing instructions, to search for in successful HTML responses.
        :param error_const_dict: Dictionary - configured dictionary of Spear
            ids, with parsing instructions, to search for to help determine if the 
            response HTML was reporting an error or not.
        :rtype List: List of Spear id/value tuples.
        """
        
        self.logger.log(NodeLogger.TRACE, "response_const_dict (%s)" % response_const_dict)
        
        parse_tuple_list = []
        
        for i in range(0, len(html_tag_list)):
            html_attr_dict = html_tag_list[i]["attr_dict"]
            if "span" == html_tag_list[i]["tag"]:
                pass
            for attr_key in html_attr_dict:
                attr_value = html_attr_dict[attr_key]
                
                # Note: Tag ids in Spear are not consistant in their casing - sometimes
                #       lowercase, sometimes camel-case. So we must insist that the 
                #       keys in 'response_const_dict' are in lowercase, and convert the
                #       HTML attribute value to lowercase before checking if its in
                #       'response_const_dict'.
                # 
                attr_value = attr_value.lower()
                
                self.logger.log(NodeLogger.TRACE, "attr_key (%s), attr_value (%s)" % (attr_key, attr_value))
                if (attr_value in response_const_dict):
                    for j in range(0, len(response_const_dict[attr_value])):
                        t = self.process_spear_tag(attr_value, response_const_dict[attr_value][j], html_tag_list, i)
                        if (t is not None):
                            parse_tuple_list.append(t)
                elif (attr_value in error_const_dict):
                    for j in range(0, len(error_const_dict[attr_value])):
                        t = self.process_spear_tag(attr_value, error_const_dict[attr_value][j], html_tag_list, i)
                        if (t is not None):
                            parse_tuple_list.append(t)
                else:
                    pass
        
        return parse_tuple_list
    
    def process_spear_tag(self, spear_id, config_dict, html_tag_list, i):
        """
        This function determines the data for the argument 'spear_id' using the
        parsing instructions in the argument 'config_dict'. Data is parsed from
        the argument 'html_tag_list' starting from position 'i'. If data is found 
        then a tuple(spear_id, data) is returned.
        
        :param spear_id: String - Spear data id for which we are parsing for data.
        :param config_dict: Dictionary - Configured parsing instructions
            for 'spear_id'.
        :param html_tag_list: List - list of HTML tags, attributes and data.
        :param i: int - current index into 'html_tag_list' from which to start
            applying parsing instructions.
        :rtype: tuple or None.
        """
        
        self.logger.log(NodeLogger.TRACE, "spear_id (%s), config_dict (%s), i (%s)" % (spear_id, config_dict, i))
        
        do_parse = True
        i2 = i
        
        config_type = config_dict["type"]
        config_alias = config_dict["alias"]
        config_start_list = config_dict["start"]
        config_end_dict = config_dict["end"]
        config_end_opentag_dict = config_end_dict["opentag"]
        config_end_closetag = config_end_dict["closetag"]
        
        # convert the argument spear_id to its alias, if one is provided in the config.
        #
        if (len(config_alias) > 0):
            spear_id = config_alias
        
        if (len(config_dict["start"]) > 0):
            for j in range(0, len(config_start_list)):
                config_start_tag = config_start_list[j]
                i2 += 1
                
                # we are matching against open-tags so we must ignore all close-tags
                # (ie. where "tag" is empty).
                #
                while (len(html_tag_list[i2]["tag"]) == 0):
                    i2 += 1
                
                if (config_start_tag != html_tag_list[i2]["tag"]):
                    self.logger.log(NodeLogger.TRACE, "Config tag[%s] (%s) does not match HTML tag (%s)" % (j, config_start_tag, html_tag_list[i2]["tag"]))
                    do_parse = False
                    break
                else:
                    self.logger.log(NodeLogger.TRACE, "Config tag[%s] (%s) matches HTML tag (%s)" % (j, config_start_tag, html_tag_list[i2]["tag"]))
        
        html_data = html_tag_list[i2]["data"]
        html_attr_dict = html_tag_list[i2]["attr_dict"]
        output_data_list = []
        
        if (do_parse is True):
            # parse the HTML tags until we find the "end" as specified by either
            # the "opentag" or "closetag" crriteria.
            #
            # Use "opentag" or "closetag"?
            #
            if (len(config_end_opentag_dict["tag"]) > 0) or \
               (len(config_end_opentag_dict["attr"]) > 0):
                # if "end" opentag equals the current i2 HTML tag then keep iterating
                # through the HTML tags until the "end" attribute/value are matched
                # or the next tag is different.
                #
                if (len(config_end_opentag_dict["tag"]) == 0):
                    self.logger.log(NodeLogger.TRACE, "No config end tag specified. Checking end attribute....")
                    
                    get_data = False
                    
                    if (config_end_opentag_dict["attr"] in html_attr_dict):
                        if (len(config_end_opentag_dict["attrvalue"]) > 0):
                            if (config_end_opentag_dict["attrvalue"] == html_attr_dict[config_end_opentag_dict["attr"]]):
                                self.logger.log(NodeLogger.TRACE, "Found end opentag attr (%s) and attr value (%s)" % (config_end_opentag_dict["attr"], config_end_opentag_dict["attrvalue"]))
                                get_data = True
                            else:
                                self.logger.log(NodeLogger.TRACE, "Found end opentag attr (%s) but attr value (%s) doesn't match." % (config_end_opentag_dict["attr"], config_end_opentag_dict["attrvalue"]))
                        else:
                            self.logger.log(NodeLogger.TRACE, "Found end opentag attr (%s) (No attr value specified)" % (config_end_opentag_dict["attr"]))
                            get_data = True
                    else:
                        self.logger.log(NodeLogger.TRACE, "End opentag attr (%s) not found in html_attr_dict." % (config_end_opentag_dict["attr"]))
                        
                    if (get_data is True):
                        if (config_end_opentag_dict["return"] == "data"):
                            self.logger.log(NodeLogger.TRACE, "Returning HTML data (%s)..." % (html_tag_list[i2]["data"]))
                            output_data_list.append(html_tag_list[i2]["data"])
                        elif (config_end_opentag_dict["return"] == "attribute"):
                            self.logger.log(NodeLogger.TRACE, "Returning attribute (%s) value (%s)..." % (config_end_opentag_dict["attr"], html_attr_dict[config_end_opentag_dict["attr"]]))
                            output_data_list.append(html_attr_dict[config_end_opentag_dict["attr"]])
                    
                elif (html_tag_list[i2]["tag"] == config_end_opentag_dict["tag"]):
                    self.logger.log(NodeLogger.TRACE, "Config end opentag (%s), current HTML tag (%s)" % (config_end_opentag_dict["tag"], html_tag_list[i2]["tag"]))
                    
                    get_data = False
                    while (html_tag_list[i2]["tag"] == config_end_opentag_dict["tag"]):
                        self.logger.log(NodeLogger.TRACE, "Config end opentag (%s) matches HTML tag. Checking config attr and attr value..." % (config_end_opentag_dict["tag"]))
                        
                        html_attr_dict = html_tag_list[i2]["attr_dict"]
                        
                        if (len(config_end_opentag_dict["attr"]) > 0):
                            if (config_end_opentag_dict["attr"] in html_attr_dict):
                                if (len(config_end_opentag_dict["attrvalue"]) > 0):
                                    if (config_end_opentag_dict["attrvalue"] == html_attr_dict[config_end_opentag_dict["attr"]]):
                                        self.logger.log(NodeLogger.TRACE, "Found end opentag (%s), attr (%s) and attr value (%s)" % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"], config_end_opentag_dict["attrvalue"]))
                                        get_data = True
                                        break
                                    else:
                                        self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) and attr (%s) but attr value (%s) doesn't match." % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"], config_end_opentag_dict["attrvalue"]))
                                else:
                                    self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) and attr (%s) (No attr value specified)" % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"]))
                                    get_data = True
                                    break
                            else:
                                self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) but attr (%s) not in html_attr_dict" % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"]))
                                
                                # Compare next HTML tag with next configured tag.
                                #
                        else:
                            self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) (No attr specified)" % (config_end_opentag_dict["tag"]))
                            
                            # Compare next HTML tag with next configured tag.
                            #
                        
                        i2 += 1
                        
                        self.logger.log(NodeLogger.TRACE, "Config end opentag (%s), current HTML tag (%s)" % (config_end_opentag_dict["tag"], html_tag_list[i2]["tag"]))
                        
                    else:
                        self.logger.log(NodeLogger.TRACE, "Config end opentag (%s) does not match current HTML tag (%s)" % (config_end_opentag_dict["tag"], html_tag_list[i2]["tag"]))
                    
                    if (get_data is True):
                        if (config_end_opentag_dict["return"] == "data"):
                            self.logger.log(NodeLogger.TRACE, "Returning HTML data (%s)..." % (html_tag_list[i2]["data"]))
                            output_data_list.append(html_tag_list[i2]["data"])
                        elif (config_end_opentag_dict["return"] == "attribute"):
                            self.logger.log(NodeLogger.TRACE, "Returning attribute (%s) value (%s)..." % (config_end_opentag_dict["attr"], html_attr_dict[config_end_opentag_dict["attr"]]))
                            output_data_list.append(html_attr_dict[config_end_opentag_dict["attr"]])
                
                else:
                    self.logger.log(NodeLogger.TRACE, "Searching HTML tags for config end tag (%s)..." % (config_end_opentag_dict["tag"]))
                    
                    # "end" open-tag does not match current HTML tag so let's search for 
                    # end open-tag, collecting data along the way. It doesn't make sense to 
                    # collect attribute data when searching for the open-tag.
                    #
                    while (i2 < len(html_tag_list)):
                        html_attr_dict = html_tag_list[i2]["attr_dict"]
                        html_data = html_tag_list[i2]["data"]
                        output_data_list.append(html_data)
                        
                        if (html_tag_list[i2]["tag"] == config_end_opentag_dict["tag"]):
                            if (len(config_end_opentag_dict["attr"]) > 0) and \
                               (config_end_opentag_dict["attr"] in html_attr_dict):
                                if (len(config_end_opentag_dict["attrvalue"]) > 0) and \
                                   (config_end_opentag_dict["attrvalue"] == html_attr_dict[config_end_opentag_dict["attr"]]):
                                    self.logger.log(NodeLogger.TRACE, "Found end opentag (%s), attr (%s) and attr value (%s)" % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"], config_end_opentag_dict["attrvalue"]))
                                    break
                                else:
                                    self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) and attr (%s) (No attr value specified)" % (config_end_opentag_dict["tag"], config_end_opentag_dict["attr"]))
                                    break
                            else:
                                self.logger.log(NodeLogger.TRACE, "Found end opentag (%s) (No attr specified)" % (config_end_opentag_dict["tag"]))
                                break
                        
                        i2 += 1
            
            elif (len(config_end_dict["closetag"]) > 0):
                # We are searching for a specific HTML close-tag so we must 
                # collect HTML data along the way. It doesn't make sense to 
                # return attribute data when searching for a close-tag.
                #
                self.logger.log(NodeLogger.TRACE, "Config closetag (%s), current HTML tag (%s)" % (config_end_closetag, html_tag_list[i2]["tag"]))
                
                if (html_tag_list[i2]["closetag"] == config_end_closetag):
                    self.logger.log(NodeLogger.TRACE, "Config closetag (%s) matches current HTML closetag (%s)" % (config_end_closetag, html_tag_list[i2]["closetag"]))
                    
                    html_data = html_tag_list[i2]["data"]
                    output_data_list.append(html_data)
                    
                else:
                    while (html_tag_list[i2]["closetag"] != config_end_closetag):
                        self.logger.log(NodeLogger.TRACE, "Config closetag (%s) does not match HTML closetag (%s). Collecting data..." % (config_end_closetag, html_tag_list[i2]["closetag"]))
                        
                        html_data = html_tag_list[i2]["data"]
                        output_data_list.append(html_data)
                        
                        i2 += 1
                    else:
                        self.logger.log(NodeLogger.TRACE, "Config closetag (%s) matches current HTML closetag (%s)" % (config_end_closetag, html_tag_list[i2]["closetag"]))
                
            else:
                # neither "end" criteria specified. Return data from current tag
                # regardless of what the "return" data should be.
                #
                html_data = html_tag_list[i2]["data"]
                output_data_list.append(html_data)
        
            # convert the output data from string to its configured type.
            #
            if (len(config_type) > 0):
                new_output_data_list = []
                for data in output_data_list:
                    new_output_data_list.append(self.cast_data(config_type, data))
                output_data_list = new_output_data_list
        
        self.logger.log(NodeLogger.TRACE, "Returning spear_id (%s), data (%s)" % (spear_id, output_data_list))
        
        return (spear_id, output_data_list)

    
    def do_url_argument_replacement(self, request_url, params_dict):
        """
        This function performs replacements in the argument 'request_url',
        substituting keys with values from 'params_dict'. 
        
        :param request_url: String
        :param params_dict: dict
        :rtype: String - resultant Url
        """
        
        for p in params_dict:
            p_sub = '${' + p + '}'
            if (request_url.find(p_sub) > 0):
                request_url = request_url.replace(p_sub, params_dict[p])
        
        return request_url
    
    def cast_data(self, type, data):
        """
        Convert the argument String 'data' to the type specified by the argument
        'type'. The cast data is returned.
        
        Note: 
            Spear is returning dates in different formats. Some such as
            'sid002b_date_lodged_with_responsible_authority' are returned 
            with the format::
            
                dd/mm/YYYY
            
            while others such as 'sid004_date' are returned as::
            
                YYYY-mm-dd hh:MM:ss.s
            
            However a browser always sees the dates as::
            
                dd/mm/YYYY
            
            So, here we will normalise the dates to the format::
            
                dd/mm/YYYY
            
            We must parse dates using date.strptime() to ensure they are dates,
            but then we must convert them back to strings (with date.strftime())
            because Resource cannot handle python 'date' values.
            
        :param type: Uri - Yarra type to cast 'data' to
        :param data: String - the data to cast
        :rtype: Any - the cast data
        """
        
        self.logger.log(NodeLogger.TRACE, "cast_data(): type (%s), data (%s)" % (type, data))
        cast_data = None
        
        # check the type of the attribute being parsed.
        #
        if (type == Uri('term:type/none')):
            cast_data = None
        elif (type == Uri('term:type/boolean')):
            if (len(data) > 0):
                try:
                    cast_data = bool(data)
                except:
                    cast_data = False
            else:
                cast_data = False
        elif (type == Uri('term:type/int')):
            if (len(data) > 0):
                try:
                    cast_data = int(data)
                except:
                    cast_data = 0
            else:
                cast_data = 0
        elif (type == Uri('term:type/long')):
            if (len(data) > 0):
                try:
                    cast_data = long(data)
                except:
                    cast_data = 0
            else:
                cast_data = 0
        elif (type == Uri('term:type/float')):
            if (len(data) > 0):
                try:
                    cast_data = float(data)
                except:
                    cast_data = 0.0
            else:
                cast_data = 0.0
        elif (type == Uri('term:type/unicode')):
            if (len(data) > 0):
                cast_data = unicode(data)
            else:
                cast_data = u""
        elif (type == Uri('term:type/string')):
            if (len(data) > 0):
                cast_data = self.filter_string_data(data)
            else:
                cast_data = ""
        elif (type == Uri('term:type/uri')):
            if (len(data) > 0):
                cast_data = Uri(data)
            else:
                cast_data = Uri("")
        elif (type == Uri('dc:date')):
            try:
                # This code validates the date format, even though it looks
                # like we could simply assign 'data' to 'cast_data'. It will
                # generate an exception if the format is not as described.
                # 
                dt = datetime.strptime(data, "%d/%m/%Y")
                
                # convert date back to a string because Resource cannot handle 'date' values.
                #
                cast_data = dt.strftime("%d/%m/%Y")
            except ValueError:
                try:
                    dt = datetime.strptime(data, "%Y-%m-%d %H:%M:%S.%f")
                    
                    # convert date back to a string because Resource cannot handle 'date' values.
                    #
                    cast_data = dt.strftime("%d/%m/%Y")
                except ValueError:
                    # return an empty string for invalid and empty dates.
                    #
                    cast_data = ""
        
        return cast_data
    
    def filter_string_data(self, source_string):
        """
        This function replaces some garbage in the Spear HTML with whitespace.
        
        - replace tabs with a single space.
        - replace newlines and carraige returns with a single space.
        - replace all multiple spaces with a single space.
        
        :param source_string: String - the string to filter
        :rtype: String - the filtered string
        """

        output_string = source_string.replace("\t", " ")
        output_string = output_string.replace("\n", " ")
        output_string = output_string.replace("\r", " ")
        output_string = re.sub(r"\ +", " ", output_string)
        
        return output_string
    
    def get_spear_requests_from_ds(self):
        """
        This function requests the DataStore for all Resources of type
        'spear:type/request'. For each found Resource we then request the 
        DataStore for the Resources matching the instructions in the 
        instruction list of each found Resource.
        
        :rtype: List - list of actions.
        """

        rs_list = []
        
        try:
            request_rs_list = self.get_requests_resources_from_datastore()
            if (request_rs_list is not None) and (len(request_rs_list) > 0):
                for rs in request_rs_list:
                    rs.set_var("instructions_dict_list", self.get_spear_request_instructions_from_ds(rs))
                    rs_list.append(rs)
        except NotFoundException:
            self.logger.log(logging.ERROR, "Uri 'spear:type/request' not found in datastore")
        
        return rs_list
    
    def get_requests_resources_from_datastore(self):
        return self.datastore.find([(Uri('term:base/datastore/resource/type'), Uri('spear:type/request'))])
    
    def get_spear_request_instructions_from_ds(self, rs):
        """
        This function requests the DataStore for the Resources matching the
        instructions in the instruction list in the argument Resource.
        
        Here we create a list of dictionaries, one dictionary per instruction 
        Resource. Each dictionary contains the instruction's:
        
        - request_python_code
        - response_python_code
        - error_python_code
        - request_const_dict
        - response_const_dict
        - error_const_dict
        - request[request_params]
        - request[url]
        - response[url]
        - response[ignore]

        :param rs: Resource
        :rtype: List of dict - list of instructions
        """

        instruction_dict_list = []
        
        instructions_list = rs.get_var("instructions")
        
        for instruction_uri in instructions_list:
            instruction_rs = self.get_instruction_resource_from_datastore(instruction_uri)
            if instruction_rs:
                dict = self.create_instruction_dict_from_instruction_resource(instruction_rs)
                instruction_dict_list.append(dict)
        return instruction_dict_list
    
    def get_instruction_resource_from_datastore(self, instruction_uri):
        try:
            rs_list = self.datastore.find([(Uri('term:base/datastore/resource/type'), Uri('spear:type/instruction')),
                                           (Uri('spear:instruction/uri'), instruction_uri)])
            return rs_list[0]
        except NotFoundException:
            self.logger.log(logging.ERROR, "instruction (%s) not found in datastore" % instruction_uri)
            return None
        
    def create_instruction_dict_from_instruction_resource(self, instruction_resource):
        dict = {}
        dict["metadata_instruction_uri"] = instruction_resource.get_metadata(Uri("spear:instruction/uri"))
        dict["request_const_dict"] = instruction_resource.get_var("request_const_dict")
        dict["request_python_code"] = instruction_resource.get_var("request_python_code")
        dict["response_const_dict"] = instruction_resource.get_var("response_const_dict")
        dict["response_python_code"] = instruction_resource.get_var("response_python_code")
        dict["error_const_dict"] = instruction_resource.get_var("error_const_dict")
        dict["error_python_code"] = instruction_resource.get_var("error_python_code")
        dict["request"] = instruction_resource.get_var("request")
        dict["response"] = instruction_resource.get_var("response")
        return dict
    
    def update_spear_connection_status(self, code):
        date = datetime.now().strftime("%Y%m%dT%H%M%S")        
        if (code < 0):
            connection_up = False 
        else:
            connection_up = True
        
        self.last_spear_connection_status = (date, connection_up)
        
        
    
class SpearHTMLParser(HTMLParser):
    """
    Internal class used by A2PSpearTask to process Spear pages.
    
    :param tag_list: List - list of HTML tags to process.
    """

    def __init__(self, tag_list):
        # Constructor
        #
        # Parameters:
        #     attributes :
        #
        
        HTMLParser.__init__(self)
        
        self.logger = logging.getLogger('eplanning.spear.a2ptask.SpearHTMLParser')
        
        self.tag_list = tag_list
        self.get_data = False
        
    def handle_starttag(self, tag, attrs):
        """
        This function is called by HTMLParser when an HTML start tag is
        encountered. The tag's name and attributes are passed.
        
        :param tag: String - the tag name
        :param attrs: List - list of (name, value) pairs
        """
        
        self.logger.log(NodeLogger.TRACE, "tag (%s) attrs (%s)" % (tag, attrs))
        
        attr_dict = {}
        for (name, value) in attrs:
            if (value is not None):
                attr_dict[name] = value
        
        tag_dict = {}
        tag_dict["tag"] = tag
        tag_dict["closetag"] = ""
        tag_dict["data"] = ""
        tag_dict["attr_dict"] = attr_dict
        self.tag_list.append(tag_dict)
        
        self.get_data = True
        
    def handle_endtag(self, tag):
        """
        This function is called by HTMLParser when an HTML end tag is
        encountered. The tag's name is passed.
        
        :param tag: String - the tag name
        """
        
        self.logger.log(NodeLogger.TRACE, "========  endtag" )
        
        tag_dict = self.tag_list[-1]
        if (tag_dict["tag"] == tag):
            tag_dict["closetag"] = tag
        else:
            tag_dict = {}
            tag_dict["tag"] = ""
            tag_dict["closetag"] = tag
            tag_dict["data"] = ""
            tag_dict["attr_dict"] = {}
            self.tag_list.append(tag_dict)
        
        self.get_data = False
        
    def handle_data(self, data):
        """
        This function is called by HTMLParser when arbitrary data is
        encountered. The data is passed.
        
        :param data: String - HTML data
        """
        
        if (self.get_data is True) and (data is not None) and (len(data.strip()) > 0):
            tag_dict = self.tag_list[-1]
            tag_dict["data"] = data.strip()
            
            self.logger.log(NodeLogger.TRACE, "saving tag (%s) data (%s), type (%s)" % (tag_dict["tag"], data.strip(), type(data)))
        else:
            self.logger.log(NodeLogger.TRACE, "========  not saving data (%s)" % data.strip())
            
    def handle_comment(self, data):
        """
        This function is called by HTMLParser when an HTML comment is
        encountered. The comment's contents is passed.
        
        :param data: String - HTML data
        """
        
        self.logger.log(NodeLogger.TRACE, "========  comment" )

    def handle_charref(self, name):
        """
        This function is called by HTMLParser when an HTML character reference
        (ie. "&#..;) is encountered. The reference is passed.
        
        :param name: String - an HTML character reference
        """
        
        self.logger.log(NodeLogger.TRACE, "========  charref" )
        
    def handle_entityref(self, name):
        """
        This function is called by HTMLParser when a general HTML entity
        reference (ie. &name;) is encountered. The reference is passed.
        
        :param name: String - an HTML entity reference
        """
        
        self.logger.log(NodeLogger.TRACE, "========  entityref" )
    
    def handle_decl(self, decl):
        """
        This function is called by HTMLParser when an SGML declaration is
        encountered. The 'decl' parameter will be the entire contents of the 
        declaration inside the <!...> markup.
        
        :param decl: String
        """
        
        self.logger.log(NodeLogger.TRACE, "========  decl" )
    
    def handle_pi(self, data):
        """
        This function is called by HTMLParser when an SGML processing instruction
        (ie. <?proc color='red'>) is encountered. The 'data' parameter will contain 
        the entire processing instruction.
        
        :param data: String
        """
        
        self.logger.log(NodeLogger.TRACE, "========  pi" )
    
    def finish(self):
        self.logger.log(NodeLogger.TRACE, "========  finish" )
        return self.base
